JSON出力に対応したPostgreSQL 15のログをCloudWatch Logs Insightで検索する

じゅんや

2023.03.07

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

2023/2/28についにRDS for PostgreSQLが正式にメジャーバージョンの15に対応しました。

Amazon RDS for PostgreSQL now supports major version PostgreSQL 15

正式リリースとのことPostgreSQL 15の追加機能を読み直していたのですが、
ログのフォーマットがjsonで出力できるようになっていました。

単体で読んでいる時はあまり気にしていなかったのですが、
RDSで取り扱うのであればCloudWatch Logsにお世話になる、
つまりCloudWatch Logs Insightとの相性が抜群では？と気づきました。

実際にどのような形で見ることができるのか気になったので試してみます。

RDS for PostgreSQLは現時点では未対応

さて記事のきっかけはPostgreSQL 15のRDSの正式対応となりますが、
残念なことに現時点ではパラメータグループのバリデーションを確認すると
log_destinationに対してjsonlogの値が許可されていない状態となりました。

あくまで現時点で対応していないだけで将来的に対応される可能性はあると思いますので、
今回はそれを信じEC2上に立てたPostgreSQLのログを出力して確認します。

実行環境

AlmaLinux release 9.1
PostgreSQL 15.2

Amazon Linux 2のextrasには15がまだ入っていなかったのでAlmaLinuxで作業を行います。
IAMロール等の設定は省略します。

PostrgeSQLに必要な設定

20.8. Error Reporting and Logging

今回対応したjson形式のでログを出力はlog_destinationの値をjsonlogに設定することで対応できます。

またドキュメントに記載のあるとおりlogging_collectorをonにする必要があるので注意しましょう。

https://www.postgresql.org/docs/15/runtime-config-logging.html#GUC-LOG-DESTINATION
If jsonlog is included in log_destination, log entries are output in JSON format, which is convenient for loading logs into programs. See Section 20.8.5 for details. logging_collector must be enabled to generate JSON-format log output.

PostgreSQLのセットアップ

インストールと初期化、ログ関連の設定の追加をします。

$ yum install -y https://download.postgresql.org/pub/repos/yum/reporpms/EL-9-x86_64/pgdg-redhat-repo-latest.noarch.rpm
...
$ yum install -y postgresql15 postgresql15-server
...
$ postgresql-15-setup initdb
...
# ついでにログ関連は色々出るようにしておく
$ cat <<EOS >> ~postgres/15/data/postgresql.conf
log_destination=jsonlog
logging_collector=on
log_connections=on
log_statement=all
EOS
$ service postgresql-15 start

ログはデフォルトでは以下の場所に配置されます。

$ ls -l ~postgres/15/data/log/
total 8
-rw-------. 1 postgres postgres 2317 Mar  6 11:29 postgresql-Mon.json
-rw-------. 1 postgres postgres  169 Mar  6 11:29 postgresql-Mon.log

CloudWatch Logs エージェントのセットアップ

AlmaLinuxのデフォルトのリポジトリにはCloudWatch Logs エージェントは存在しないためS3上のパッケージよりインストールします。

$ yum install -y https://s3.ap-northeast-1.amazonaws.com/amazoncloudwatch-agent-ap-northeast-1/redhat/amd64/latest/amazon-cloudwatch-agent.rpm
...
$ cat <<EOS > /opt/aws/amazon-cloudwatch-agent/etc/amazon-cloudwatch-agent.json
{
    "agent": {
        "run_as_user": "postgres"
    },
    "logs": {
        "logs_collected": {
            "files": {
                "collect_list": [
                    {
                        "file_path": "/var/lib/pgsql/15/data/log/*.json",
                        "log_group_name": "/local/{instance_id}",
                        "log_stream_name": "postgresql.json",
                        "retention_in_days": 3
                    }
                ]
            }
        }
    }
}
EOS
$ service amazon-cloudwatch-agent start

この時点でCloudWatch Logs上にログが上がっていることを確認します。

ログ確認用にPostgreSQLに接続

セットアップアップのログも上がっているはずですが
念の為接続＋クエリの実行でログを生成しておきます。

$ su - postgres
...
$ psql
psql (15.2)
Type "help" for help.

postgres=#
postgres=#
postgres=# SELECT version();
                                                 version
----------------------------------------------------------------------------------------------------------
 PostgreSQL 15.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 11.3.1 20220421 (Red Hat 11.3.1-2), 64-bit
(1 row)

stderrの場合のログ

JSON形式のログを見る前に
まずは一度一度標準のstderrで出力されるログを見てみましょう。

こちらは別途RDSで確認しようとした時に出力されたログですが、
プレーンテキスト形式のためCloudWatch Logs Insightで見ると特にフィールドが分かれず@messageから頑張って検索をかける必要があります。

jsonlogの場合のログ

JSONで出力されることにより各パラメータがフィールドごとに分かれており、
CloudWatch LogsやInsight上では見通しが良さそうです。

postgresユーザで接続しに行く前に誤ってrootユーザで接続しに行き、
認証に失敗していたのでそのログを探してみましょう。

fields @timestamp,error_severity, @message, @logStream, @log
| filter error_severity = 'FATAL'
| filter user = 'root'
| sort @timestamp desc
| limit 20

失敗しているログを抽出することができました。

ログの詳細としては以下のような出力となります。

今回特にrootユーザはクエリを流していないので省略しましたが、
実際はfilter ps = 'authentication'もつけて探す方が良さそうです。

終わりに

さて今回はPostgreSQLのログをJSONで出力し、
CloudWatch Logs Insightで簡単に調査を行ってみました。

フィールド毎に検索をかけられるようになったことで、
これまで直感的にクエリをかけログを調査することができるようになったのではないかと思います。

サーバ上でgrepをかけて目で追えるレベルであればむしろJSONは見づらいかと思いますので、
ログ分析サービスを使っているような環境だからこそ嬉しいアップデートだと個人的には思っています。

※実際着色無しのJSONを見るのはかなり辛いと思います。

{"timestamp":"2023-03-06 12:14:18.828 UTC","pid":954,"session_id":"6405d7ee.3ba","line_num":1,"session_start":"2023-03-06 12:09:18 UTC","txid":0,"error_severity":"LOG","message":"checkpoint starting: time","backend_type":"checkpointer","query_id":0}
{"timestamp":"2023-03-06 12:14:18.834 UTC","pid":954,"session_id":"6405d7ee.3ba","line_num":2,"session_start":"2023-03-06 12:09:18 UTC","txid":0,"error_severity":"LOG","message":"checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.002 s, total=0.006 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB","backend_type":"checkpointer","query_id":0}

まさにRDSだからこそ必要とする機能なので対応してくれることを信じて祈っております。